Skip to content

tests: enhance functional test with more checks.#77

Open
pponnuvel wants to merge 4 commits intotaodd:mainfrom
pponnuvel:enhance-ft
Open

tests: enhance functional test with more checks.#77
pponnuvel wants to merge 4 commits intotaodd:mainfrom
pponnuvel:enhance-ft

Conversation

@pponnuvel
Copy link
Collaborator

@pponnuvel pponnuvel commented Jan 22, 2026

Fixes SET-1807.

@pponnuvel pponnuvel force-pushed the enhance-ft branch 5 times, most recently from a741dbd to 8e84cfc Compare January 24, 2026 07:20
@pponnuvel pponnuvel marked this pull request as draft January 24, 2026 07:51
@pponnuvel pponnuvel force-pushed the enhance-ft branch 7 times, most recently from 40e36fb to f47fac3 Compare January 26, 2026 15:22
@pponnuvel pponnuvel marked this pull request as ready for review January 26, 2026 15:26
@pponnuvel pponnuvel requested a review from taodd January 26, 2026 15:26
@pponnuvel
tests: enhance functional test with more checks.
22de820 
Fixes SET-1807.

Fixes taodd#24.

Signed-off-by: Ponnuvel Palaniyappan <pponnuvel@gmail.com>
taodd
taodd reviewed Jan 28, 2026
View reviewed changes
Copy link
Owner

@taodd taodd left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some minor change required.
@pponnuvel thank you very much for the patch. The osdtrace works great, However, from the log output, it seems radostrace still can't output anything.

@pponnuvel
fix bugs and address comments from Dongdong
5589ba9 
Signed-off-by: Ponnuvel Palaniyappan <pponnuvel@gmail.com>
@pponnuvel
Add helpers to print messages in consistent format
ea8715d 
Signed-off-by: Ponnuvel Palaniyappan <pponnuvel@gmail.com>
@pponnuvel
Copy link
Collaborator Author

pponnuvel commented Jan 28, 2026

Some minor change required. @pponnuvel thank you very much for the patch. The osdtrace works great, However, from the log output, it seems radostrace still can't output anything.

Thanks @taodd!

I've fixed the issue with radostrace now. All look fine now - please take a look again. Thanks.

taodd
taodd reviewed Jan 29, 2026
View reviewed changes
taodd
taodd reviewed Jan 29, 2026
View reviewed changes
taodd
taodd reviewed Jan 29, 2026
View reviewed changes
taodd
taodd requested changes Jan 29, 2026
View reviewed changes
Copy link
Owner

@taodd taodd left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Except the suggested comments.
The radostrace still doesn't output any trace line in the log file.
I guess it's probably because we need to specify the process id of the microceph.rbd bench command, if that's the case we'll need to adjust the order of step 10 and step 11.
add -p to the radostrace. then we should see the actual tracing data from radostrace

@pponnuvel
Fix bugs in awk usage
496d585 
Signed-off-by: Ponnuvel Palaniyappan <pponnuvel@gmail.com>
@pponnuvel
Copy link
Collaborator Author

pponnuvel commented Feb 14, 2026

Except the suggested comments. The radostrace still doesn't output any trace line in the log file. I guess it's probably because we need to specify the process id of the microceph.rbd bench command, if that's the case we'll need to adjust the order of step 10 and step 11. add -p to the radostrace. then we should see the actual tracing data from radostrace

This only happens with GH runners. Locally it produces the output:

+ cat /tmp/radostrace.log
Found library librbd.so.1 at: /snap/microceph/current/lib/x86_64-linux-gnu/librbd.so.1
Found library librados.so.2 at: /snap/microceph/current/lib/x86_64-linux-gnu/librados.so.2
Found library libceph-common.so.2 at: /snap/microceph/current/lib/x86_64-linux-gnu/ceph/libceph-common.so.2
Libraries to be traced: /snap/microceph/current/lib/x86_64-linux-gnu/librbd.so.1, /snap/microceph/current/lib/x86_64-linux-gnu/librados.so.2, /snap/microceph/current/lib/x86_64-linux-gnu/ceph/libceph-common.so.2
Importing DWARF info from /home/ponnuvel.palaniyappan@canonical.com/myGit/cephtrace/files/ubuntu/radostrace/19.2.1-0ubuntu0.24.04.2_dwarf.json
Skipping version check as requested
Start to load uprobe
Using version from JSON file: 19.2.1-0ubuntu0.24.04.2
Using Ceph squid (19.2.0+) struct offsets
Ceph struct offsets set in BPF globals:
  CEPH_OSD_OP_SIZE: 112
  CEPH_OSD_OP_EXTENT_OFFSET_OFFSET: 6
  CEPH_OSD_OP_EXTENT_LENGTH_OFFSET: 14
  CEPH_OSD_OP_BUFFER_CARRIAGE_OFFSET: 56
fill_map_hprobes: function Objecter::_finish_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_finish_op var location : register 5 offset 0 stack 0
fill_map_hprobes: function Objecter::_finish_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 5 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
fill_map_hprobes: function Objecter::_send_op var location : register 4 offset 0 stack 0
BPF prog loaded
uprobe Objecter::_send_op attached to all processes
uprobe Objecter::_send_op attached to all processes
uprobe Objecter::_finish_op attached to all processes
uprobe Objecter::_finish_op attached to all processes
New a ring buffer
Started to poll from ring buffer
No execution timeout set (unlimited).
     pid  client     tid  pool  pg          acting  WR     size  latency     object[ops]
  606258   54192       1     1  1b         [3,1,2]   W       20     8242     testobj [writefull][0, 20]
  606257   54193       1     1  1c         [3,1,2]   R        0     2321     rbd_id.testimage [stat]
  606257   54193       2     1  1c         [3,1,2]   R        0      907     rbd_id.testimage [call(rbd.get_id)]
  606257   54193       3     1  14         [2,3,1]   R        0     2347     rbd_header.d3aafa4163d6 [call(rbd.get_size) call(rbd.get_object_prefix) call(rbd.get_features)]
  606257   54193       4     1  14         [2,3,1]   R        0      583     rbd_header.d3aafa4163d6 [call(rbd.get_create_timestamp)]
  606257   54193       5     1  14         [2,3,1]   R        0      385     rbd_header.d3aafa4163d6 [call(rbd.get_access_timestamp) call(rbd.get_modify_timestamp)]
  606257   54193       6     1  14         [2,3,1]   R        0      756     rbd_header.d3aafa4163d6 [call(rbd.get_data_pool)]
  606257   54193       7     1  14         [2,3,1]   R        0     1214     rbd_header.d3aafa4163d6 [call(rbd.get_size)]
  606257   54193       8     1  14         [2,3,1]   R        0     1032     rbd_header.d3aafa4163d6 [call(rbd.parent_get) call(rbd.parent_overlap_get)]
  606257   54193       9     1  14         [2,3,1]   R        0      610     rbd_header.d3aafa4163d6 [call(rbd.metadata_list)]
  606257   54193      10     1  1a         [1,2,3]   R        0     2461     rbd_info [call(rbd.metadata_list)]
  606257   54193      11     1  14         [2,3,1]   R        0      575     rbd_header.d3aafa4163d6 [call(rbd.image_group_get)]
  606257   54193      12     1  14         [2,3,1]   W        0     5427     rbd_header.d3aafa4163d6 [watch]
  606257   54193      13     1  14         [2,3,1]   R        0      893     rbd_header.d3aafa4163d6 [call(lock.get_info)]
  606257   54193      14     1  14         [2,3,1]   W        0     6494     rbd_header.d3aafa4163d6 [call(lock.lock)]
  606257   54193      15     1  17         [3,1,2]   W        0     6336     rbd_object_map.d3aafa4163d6 [call(lock.lock)]
  606257   54193      16     1  17         [3,1,2]   R        0     1438     rbd_object_map.d3aafa4163d6 [call(rbd.object_map_load)]
  606257   54193      17     1  14         [2,3,1]   R        0      661     rbd_header.d3aafa4163d6 [notify]
  606257   54193      18     1  14         [2,3,1]   R        0     1087     rbd_header.d3aafa4163d6 [notify-ack]
  606257   54193      19     1  17         [3,1,2]   W        0     6574     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      20     1  17         [3,1,2]   W        0    15311     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      21     1  17         [3,1,2]   W        0    15151     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      22     1  17         [3,1,2]   W        0    14988     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      23     1  17         [3,1,2]   W        0    14830     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      24     1  17         [3,1,2]   W        0    14551     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      25     1  1c         [3,1,2]   W  4194304    52487     rbd_data.d3aafa4163d6.0000000000000000 [set-alloc-hint writefull][0, 4194304]
  606257   54193      26     1   c         [3,2,1]   W  4194304    46923     rbd_data.d3aafa4163d6.0000000000000040 [set-alloc-hint writefull][0, 4194304]
  606257   54193      27     1  13         [1,3,2]   W  4194304    54657     rbd_data.d3aafa4163d6.0000000000000080 [set-alloc-hint writefull][0, 4194304]
  606257   54193      31     1  17         [3,1,2]   W        0    14555     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      28     1  19         [3,2,1]   W  4194304    58943     rbd_data.d3aafa4163d6.00000000000000c0 [set-alloc-hint writefull][0, 4194304]
  606257   54193      32     1  17         [3,1,2]   W        0    12089     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      29     1   4         [3,1,2]   W  4194304    58991     rbd_data.d3aafa4163d6.0000000000000001 [set-alloc-hint writefull][0, 4194304]
  606257   54193      30     1   6         [3,1,2]   W  4194304    58985     rbd_data.d3aafa4163d6.0000000000000041 [set-alloc-hint writefull][0, 4194304]
  606257   54193      33     1  17         [3,1,2]   W        0     8958     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      35     1  17         [3,1,2]   W        0    14984     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      36     1  17         [3,1,2]   W        0    15005     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      37     1  17         [3,1,2]   W  4194304    35856     rbd_data.d3aafa4163d6.00000000000000c1 [set-alloc-hint writefull][0, 4194304]
  606257   54193      38     1  17         [3,1,2]   W        0    36193     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      34     1   3         [1,2,3]   W  4194304    47021     rbd_data.d3aafa4163d6.0000000000000081 [set-alloc-hint writefull][0, 4194304]
  606257   54193      42     1  17         [3,1,2]   W        0    16586     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      39     1  14         [2,3,1]   W  4194304    47778     rbd_data.d3aafa4163d6.0000000000000002 [set-alloc-hint writefull][0, 4194304]
  606257   54193      40     1  10         [1,2,3]   W  4194304    37630     rbd_data.d3aafa4163d6.0000000000000042 [set-alloc-hint writefull][0, 4194304]
  606257   54193      41     1   d         [2,1,3]   W  4194304    37677     rbd_data.d3aafa4163d6.0000000000000082 [set-alloc-hint writefull][0, 4194304]
  606257   54193      44     1  17         [3,1,2]   W        0     8924     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      43     1  18         [2,3,1]   W  4194304    24644     rbd_data.d3aafa4163d6.00000000000000c2 [set-alloc-hint writefull][0, 4194304]
  606257   54193      46     1  17         [3,1,2]   W        0    10416     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      47     1  17         [3,1,2]   W        0    10401     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      48     1  17         [3,1,2]   W        0    10262     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      50     1  17         [3,1,2]   W        0    21447     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      45     1  18         [2,3,1]   W  4194304    32408     rbd_data.d3aafa4163d6.0000000000000003 [set-alloc-hint writefull][0, 4194304]
  606339   54197       1     1  1b         [3,1,2]   R  4194304     1265     testobj [read][0, 4194304]
  606257   54193      52     1   7         [1,3,2]   W  4194304    39392     rbd_data.d3aafa4163d6.00000000000000c3 [set-alloc-hint writefull][0, 4194304]
  606257   54193      49     1   c         [3,2,1]   W  4194304    49413     rbd_data.d3aafa4163d6.0000000000000083 [set-alloc-hint writefull][0, 4194304]
  606257   54193      55     1  17         [3,1,2]   W        0    25641     rbd_object_map.d3aafa4163d6 [call(lock.assert_locked) call(rbd.object_map_update)]
  606257   54193      51     1  19         [3,2,1]   W  4194304    47439     rbd_data.d3aafa4163d6.0000000000000043 [set-alloc-hint writefull][0, 4194304]
  606257   54193      54     1  1e         [3,1,2]+ info ' === END of RADOS trace === '

Do we know if radostrace every produced any output in the past? We only checked if it runs but not whether it produces any tracing logs. I suspect this has never worked. In any case, it's certainly needs to be investigated.

@pponnuvel
Copy link
Collaborator Author

pponnuvel commented Feb 16, 2026

Confirmed with main too: https://github.com/taodd/cephtrace/actions/runs/22072454615/job/63785379309?pr=80 radostrace doesn't produce any trace output.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@taodd taodd taodd requested changes

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

2 participants

@pponnuvel @taodd